chdkfandomcom-20200222-history
Debugging
Introduction This page collects tools and techniques for debugging CHDK code LEDs A simple way to see if a particular code path is reached. In a complete CHDK port the started() and finished() macros turn on and off the CHDK debug LED . The debug LED is normally the blue direct print LED. On cameras that do not have a direct print LED, a different one will be used. The AF led should NOT be set as the debug LED in any build intended for normal use, because it would interfere with taking pictures. Using LEDs directly First, you need to know an LED MMIO address. TODO link some led finder code. The LED is turned on by writing 0x46 to the address, and turned off by writing 0x44 C From C, you can do something like this to blink an LED cnt times. The nops are used to create a delay. The length of the delay will depend on the camera and whether caches are currently enabled, but should be sufficient to see the led blinking. #define LED_PR 0xc0220134 // your LED address ... volatile int *p=(void*)LED_PR; for(;cnt>0;cnt--){ *p=0x46; for(i=0;i<0x200000;i++){ asm ("nop\n"); asm ("nop\n"); } *p=0x44; for(i=0;i<0x200000;i++){ asm ("nop\n"); asm ("nop\n"); } } Some things to watch out for * If you call this code from inline assembler, you need to make sure to preserve any registers. The ASM_SAFE macro may be used for this purpose (see the include/asmsafe.h file for more details) * In some parts of the code, the stack may not be properly set up, in which case any variables should be static or global. * If you want to put this code in an __attribute__((naked)) function, you should also avoid using local variables. In general you should not put any C code in these functions. * In some parts of the code - especially early in the booting process - the use of delay loops to actually blink the camera LED can potentially disrupt the boot timing. It is safer to simply turn on the LED rather than blink it. #define LED_PR 0xc0220134 // your LED address volatile int *p=(void*)LED_PR; *p=0x46; .. Assembler You might want to blink an LED directly from assembler code // for testing, blink LED at 0xC0220130 10 times LDR R3, =0xC0220130 MOV R1,#10 1: MOV R2, #0x46 STR R2, R3 MOV R0, #0x8000 2: SUB R0,R0,#1 CMP R0,#0 BNE 2b MOV R2, #0x44 STR R2, R3 MOV R0, #0x8000 3: SUB R0,R0,#1 CMP R0,#0 BNE 3b SUB R1,R1,#1 CMP R1,#0 BNE 1b A safer version of this suitable for inserting inline into the CHKD boot.c, capt_seq.c and movie_rec.c files is " STMFD SP!, {R0,R1} \n" " LDR R0, =0xC02200D4 \n" " MOV R1, #0x46 \n" " STR R1, R0 \n" " LDMFD SP!, {R0,R1} \n" Remember to change the 0xC02200D4 value in the second line to the address of your camera's LED>. Using LEDs from Canon Basic/Eventprocs The LEDs can also be controlled using the LEDDrive function, either from Canon Basic or as an Event Procedure. Camera crash logs (romlog) When the canon firmware crashes, it will normally write the current registers, a stack dump, and the recent entries from the camera log to internal flash memory and then shut down. This is generally referred to as the romlog. Reading the romlog As of changeset 1432, the romlog can be saved from the CHDK menu, using "miscellaneous stuff->Debug Parameters->Save ROM crash log" The romlog can also be saved to to a file using Canon_Basic/Scripts/Romlog or Lua/Scripts:Standard/Test/Romlog Notes * Some older vxworks cameras will automatically shut down after saving the log. This is normal. * If the camera has never crashed, the romlog function will fail. Interpreting the romlog Text below refers the the plain text romlogs produced by DryOS and some later vxworks cameras. Older vxworks cameras output the romlog in a binary format, some information is available in this forum thread http://chdk.setepontos.com/index.php?topic=5394.0 The first line of the romlog describes the kind of error that occurred. Known errors include ASSERT, EXCEPTION, WATCHDOG and HARDWARE DEFECT. ASSERT and EXCEPTION are most commonly encountered in CHDK development. The remainder of the log varies slightly depending on the error. Example assert ASSERT!! FsIoNotify.c Line 451 Occured Time 2010:06:26 18:10:53 Task ID: 1441797 Task name: SpyTask SP: 0x002FCE44 StackDump: 0x00000000 0x00000008 0xFF8187F8 ... The stack dump can help you figure out which functions were called an in some cases what their parameters were. Rather than actually working through all the calls, it is frequently sufficient to just look for addresses that look like code, either ROM or within CHDK address space. Keep in mind that the final entry in the stack dump is the call to assert itself. Example exception Exception!! Vector 0x10 Occured Time 2010:05:30 13:05:27 Task ID: 1441797 Task name: SpyTask Exc Registers: 0x0000007A 0x00008000 0x00000050 0x65784500 0x00000006 0x00000000 0x00000005 0x00000014 0x19980218 0x19980218 0x19980218 0x19980218 0x80000000 0x002FCEC0 0x0014C427 0x0014C43E 0x00000033 StackDump: 0xFF812398 0x00002E10 0x00000010 ... Unlike assert, the exception log includes the CPU registers at the time the exception occurred. The 15th register is LR, 16th register is the instruction pointer (PC), and the 17th is the program status word. Keep in mind the LR will point to the instruction after the BL instruction, and may have lowest bit set if the call was from thumb code. PC will not have the low bit set in thumb code. The exception vector tells you what kind of exception occurred. Descriptions of the exception handling process can be be found in the ARM9E-S Core Technical Reference Manual. Example DryOS Panic System Panic: Module = 64, Panic = 4 Occured Time 2011:04:03 13:46:30 StackDump(0x2FCED0 - 0x2FCF50): 0x002FCED0 0x0028CAB8 0x00000000 0xFF81C2E0 0x00000000 0x00000001 ... Not clear what the Module and Panic numbers mean. Example hardware defect HARDWARE DEFECT!! ShutdownReason9 ErrorNo41 Occured Time 2011:12:11 21:02:23 00000550: UI:PB.CreateE 00000560: UI:DisplayPhysicalScreenCBR 00000560: UI:AC:StartPB 00000560: UI:DispSwCon_TurnOnDisplayDevice 00000560: UI:AC:EBtn 00000560: UI:PB.Start Note the above appears to be triggered by CHDK in this case, not an actual hardware defect. thread Common Exception Vectors In CHKD debugging, the most commonly encountered exception is 0x10 Data abort. This occurs when the code attempts to access an invalid memory address. 0x4 Undefined Instruction is also is also common, caused by bad code pointers or stack corruption. A NULL function pointer can trigger 0x0 Reset. Source: ARM9E-S Core Technical Reference Manual Locating CHDK code from romlog addresses The CHDK build process writes disassembly dumps of the main CHDK binary. The dump for the main code is stored in core/main.dump The dump for the loader code (which includes the main code, but not located at the final address) is stored in loader//main.dump You can search these dumps for addresses that appear in the romlog, which will help you find the corresponding C source. Note that Thumb addresses may appear in the stack dump or registers with the lowest bit set. The CHDK-Shell tool will save dumps to bin/logs/dump-{cameraname}-{firmware}.txt by default. This is controlled by the checkbox named "ELF objdump", just above the "Compile Selected" button. You can also disable "Compile Options > Skip GMAKE clean AFTER compilation" to keep them in the original location. Debugging modules CHDK version 1.1 and later uses the Module System to run some code from loadable modules. This can make debugging more difficult be because the module addresses are not known in advance. In CHDK 1.2, turning on module logging in the modules menu will cause module load addresses to be recorded in A/MODULES.LOG. Note The recorded address is the at the start of the module. This includes a 36 byte header, so the start actual module code will be the listed address +36. When dumping an .elf with objdump, you should make sure the .text address is equal the module log address +36 (0x24). Whether an adjustment is required may depend on the toolchain. Once you have the code start address, you can disassemble the corresponding .elf with symbols and correct addresses using arm-elf-objdump -d -x --adjust-vma= mod.elf > mod.dumpobj The debug dump systems in modules/dbg_dump.c can be used record information about loaded modules at specific points in code. If you only have the .flt of a module, you can use arm-elf-objdump -m arm -Mforce-thumb -b binary -d ... Memory values There are two common ways to inspect memory values in CHDK Misc debug values This displays four memory values in the CHDK OSD. The display can be turned on or of in the CHDK menu under miscellaneous stuff->Debug parameters->Show misc. values By default, the values listed below are shown, but this can be be changed in core/gui.c gui_draw_debug_vals_osd() u: usb power state 1: the address selected in the memory browser (see below) f: the focus_busy value z: the zoom_busy value Early in the porting process, you may want to hard code this to always be displayed, and also uncomment the first call to gui_draw_debug_vals_osd() in gui_draw_osd to ensure it is drawn even if some variables are wrong. Memory browser This allows you to interactively view memory addresses. The right/left buttons increment/decrement the address, and the zoom in/zoom out controls the increment size. On cameras without zoom button or zoom lever, the Disp button can be used to change the increment size. Note that if you attempt to browse an invalid memory location (or the selected memory location holds an invalid address), the camera will shut down with an exception. By default, the value of the selected address is also shown in misc debug values, so you can use this to set a "watch" without changing code. There is a modified version of this debug tool which adds some functionality, here: http://chdk.setepontos.com/index.php?topic=6635.0 Logging camera console output Many firmware functions output information to the cameras console. Normally, this is discarded, but it it can be recorded with the following methods. Some functions that put useful information to the camera console * ShowCameraLog outputs recent entries in the cameras log. (to be described more below!) * Printf can be used to send arbitrary text to the camera console (UART). * LogCameraEvent (sometimes also referred to as LogPrintf) writes messages to the "Camera log". The camera log does not appear in the camera standard output by default, but recent entries can be sent there using the ShowCameraLog event proc. Recent Camera Log entries also appear in ROMLOGs. LogCameraEvent is not an event proc, the address can usually be found in the ports funcs_by_*.csv. It takes a number as the first argument, followed by a format string and a variable number of additional arguments. The number is a bitmask indicating the log level. The Canon firmware by default logs all messages with the bit 0x20 set. The bits 0x40 and 0x100 cause the strings UI: and SS: to prefixed to the logged string. The Canon firmware usually uses 0x60 for "UI:" messages and 0x120 for "SS:" messages. An assert is triggered if the output would be longer than about 64 characters. UART redirection (DryOS) DryOS (TODO and possibly late vxworks ?) cameras can redirect UART console output with StartRedirectUART Event Procedure. To use this function, a file named uartr.req must be present in the root of the SD card, and must start with the bytes 0x77 0x21 0xce 0x82 . StartRedirectUART(int buffer_size,const char *filename) buffer_size controls how much output is buffered. The value is rounded up to 8192 bytes. filename is the name of the file to write. If NULL, an name will be automatically picked based on tick count. If a name is given, output will be appended to the file. The standard CHDK distribution includes the uartr.lua lua module which provides an interface to this. Note that a sleep() appears to be required between enabling uart redirection and the first output being recorded. UART redirection may be stopped with StopRedirectUART() . UART Console UART Console allow access to Canon Event Shell and DryOs Shell (drysh). UART pinout on Camera PCB have to be discovered for your Camera. Look SD4000 for example. VxWorks Many VxWorks cameras support the CAM_CONSOLE_LOG_ENABLED #define in camera.h. When this is enabled, camera STDOUT will be sent to A/stdout.txt if it exists. If stdout.txt does not exist, it will not be created. Note, this may cause instability, probably because it uses standard IO functions within a device driver. Example The following example shows using the PTP Extension with the chdkptp client to get console output con 1> =require('uartr').start('A/TEST.LOG') con 2> =call_event_proc('ExMem') con 3> =call_event_proc('ExMem.View') con 4> =call_event_proc('ShowCameraLog') con 5> d test.log A/test.log->test.log The commands above # start uart redirection, appending to TEST.LOG # register the "ExMem" group of eventprocs # Call ExMem.View, which prints ExMem information to test.log # Call ShowCameraLog, which prints recent camera log entries to test.log # downloads test.log Adjusting the size of the camera log The size of the camera log can be adjusted by stopping and restarting it. ShowCameraLogInfo will output the current log level and buffer size to the camera console. The following restarts the camera log with the default log level and a 16k buffer (tested on A540 and D10, you camera may vary) call_event_proc('StopCameraLog') call_event_proc('StartCameraLog',0x20,0x4000) Category:Development Category:DEBUG